3. The Logbook Service
It's time to put all the
knowledge and intricacies described so far to good use, with a
comprehensive and useful real-life example. One of the most beneficial
steps you can take to achieve a robust application and faster time to
market is to add a logging capability to your application. This section
presents you with the logbook—a simple custom component service that
allows you to automatically log method calls and exceptions. The logbook
is your product's flight recorder, and in a distributed environment,
it's worth its weight in gold; with it, you can analyze why something
didn't work the way it was supposed to. Examining the logbook entries,
you can analyze what took place across machines and applications, and
the source of the problem is usually almost immediately evident. The
logbook is also useful for troubleshooting customer problems in
post-deployment scenarios. The logbook intercepts incoming calls to your
context-bound objects and logs most of the information in the messages.
As you will see shortly, you can use the same logbook to record method
invocations from multiple machines and have the various entries
interleaved in order.
Each logbook entry contains the following information, captured automatically by the logbook:
The location where the method was invoked: machine name, app domain name, thread ID and name, and context ID
The caller's identity (username)
Information
about the target object: its assembly, its type, and the member being
accessed (constructor, method, property, indexer, or event)
The invocation date and time
Error information, if an exception was thrown: the type of the exception and the exception message
3.1. Using the logbook
A key requirement in
designing the logbook was that it should require no explicit
participation on behalf of the object. The object should focus on
implementing its business logic, and the logbook should do the logging.
To add logging support for a context-bound object, add the LogbookAttribute custom context attribute, defined in the ContextLogger namespace:
using ContextLogger;
[Logbook]
public class MyClass : ContextBoundObject
{...}
The logbook service
allows you to choose what information to log. Sometimes, it's necessary
to record everything that takes place (method calls and errors). In
other situations, it's sufficient to log only errors and exceptions. To
that end, the logbook provides the enum LogOption, defined as:
public enum LogOption
{
MethodCalls,
Errors
}
You can provide the constructor of LogbookAttribute with the appropriate enum value. For example, to log only unhandled exceptions, write:
[Logbook(LogOption.Errors)]
public class MyClass : ContextBoundObject
{...}
The parameter-less constructor of LogbookAttribute defaults to LogOption. MethodCalls, so these two declarations are equivalent and can log both method calls and errors:
[Logbook]
[Logbook(LogOption.MethodCalls)]
3.2. The logbook service architecture
When you apply LogbookAttribute to a
context-bound class, it requires private contexts for each instance to
support logging of all calls coming into the object. If it were possible
for two objects using the LogbookAttribute to share a context, cross-context calls would be logged, but intra-context calls made on one another wouldn't. The LogbookAttribute adds to the new context a property called LogContextProperty, which contributes a server-context sink called LogSink. LogSink intercepts all calls to the object but doesn't log them itself; instead, it uses the Logbook component, which encapsulates the actual logging mechanism. The implementation provided here logs to a SQL Server database, but you can replace that with any other repository. The Logbook
is a remote singleton residing in an EXE host. As a result, all objects
using the logbook service actually log to the same repository, in
order. This is a key feature that allows you to trace the execution of a
distributed application, because the host can be on a dedicated machine
used by all other machines.
Figure 2
depicts the logbook architecture. In addition, a logbook viewer
application is provided; it displays in a grid control the content of
the logbook database entries table. The logbook viewer allows you to
filter the grid to display methods and errors, or just errors. The
application has another feature, too: you can export the logbook entries
to a logfile, as well as display the content of an existing logfile.
The logbook viewer doesn't connect to the database directly. Instead, it
too connects to the singleton Logbook.
The viewer doesn't directly connect to the database for two reasons. The
first is that if it did, you would couple the viewer to the repository
used and would have to modify the viewer each time you switched
repositories. The Logbook provides the necessary indirection. Second, to avoid database synchronization issues, the Logbook is the single data access component, and it provides the synchronization.
The source files accompanying this book include the Logbook solution. The solution comprises the following projects. The ContextLogger class library contains the LogbookAttribute, the LogContextProperty, the LogSink, and the Logbook component itself. Logbook is an ADO.NET component that can access an SQL Server database. (You will need to create a database called Logbook with an Entries table by running the included Logbook.sql script file.) The LogbookHost project is a simple Windows Forms EXE that hosts Logbook. The LogbookHost configuration file exposes the Logbook type as a server-activated singleton object. The TestClient
project is a Windows Forms application that has a test class and the
test client. The test class is a context-bound class that uses the LogbookAttribute. The test client is a form that is able to exercise various calls on the test object. The configuration file of the TestClient application registers the Logbook component as a remote server-activated object whose URL connects to the LogbookHost application. The LogbookViewer project contains the logbook viewer, which lets you browse the logbook entries or clear the table (see Figure 3). The LogbookViewer application registers the Logbook component as a remote server as well.
You can extend and
modify the logbook to suit your particular needs: you can log parameter
types and values, and you can use other repositories besides SQL Server.
3.3. Implementing the logbook
The LogbookAttribute class isn't that different from the ColorAttribute class presented in Example 1. It refuses the client's context in its IsContextOK( ) method and installs the LogContextProperty property in its GetPropertiesForNewContext( ) method. Example 2 shows the implementation of LogbookAttribute.
Example 2. Implementation of the LogbookAttribute class
[AttributeUsage(AttributeTargets.Class)]
public class LogbookAttribute : ContextAttribute
{
LogOption m_LogOption;
public LogbookAttribute( ): this(LogOption.MethodCalls)
{}
public LogbookAttribute(LogOption logOption) : base("LogbookAttribute")
{
m_LogOption = logOption;
}
/// Add a new logbook property to the new context
public override void GetPropertiesForNewContext(IConstructionCallMessage ctor)
{
IContextProperty logProperty = new LogContextProperty(m_LogOption);
ctor.ContextProperties.Add(logProperty);
}
//Called by the runtime in the creating client's context
public override bool IsContextOK(Context ctx,IConstructionCallMessage ctorMsg)
{
return false;
}
}
|
LogContextProperty implements the IContributeServerContextSink interface, installing the LogSink server context sink:
public class LogContextProperty : IContextProperty,IContributeServerContextSink
{
LogOption m_LogOption;
public IMessageSink GetServerContextSink(IMessageSink nextSink)
{
IMessageSink logSink = new LogSink(nextSink,m_LogOption);
return logSink;
}
/* Rest of the implementation */
}
The interesting part of the logbook service is the LogSink class. LogSink implements the IMessageSink interface. In its implementation of IMessageSink, LogSinkLogbookEntry structure, providing it with the information extracted from the message. LogbookEntryLogSink then passes the LogbookEntry object to the Logbook component. Because the logbook is accessed as a remote component, LogbookEntry is marshaled by value using the Serializable attribute. Example 3 contains the code for LogbookEntry. processes the message object and constructs an instance of the
stores the information provided as construction parameters and captures
additional information such as the object's location and execution
scope.
Example 3. The LogbookEntry structure
[Serializable]
public struct LogbookEntry
{
public LogbookEntry(string assemblyName,string typeName,string methodName,
string eventDescription):
this(assemblyName,typeName,methodName,String.Empty,String.Empty)
{
Event = eventDescription;
}
public LogbookEntry(string assemblyName,string typeName,string methodName):
this(assemblyName,typeName,methodName,String.Empty,String.Empty)
{}
public LogbookEntry(string assemblyName,string typeName,string methodName,
string exceptionName,string exceptionMessage)
{
AssemblyName = assemblyName;
TypeName = typeName;
MemberAccessed = methodName;
ExceptionName = exceptionName;
ExceptionMessage = exceptionMessage;
Event = String.Empty;
MachineName = Environment.MachineName;
AppDomainName = AppDomain.CurrentDomain.FriendlyName;
ThreadID = Thread.CurrentThread.ManagedThreadId( );
ThreadName = Thread.CurrentThread.Name;
ContextID = Thread.CurrentContext.ContextID;
Date = DateTime.Now.ToShortDateString( );
Time = DateTime.Now.ToLongTimeString( );
if(Thread.CurrentPrincipal.Identity.IsAuthenticated)
{
UserName = Thread.CurrentPrincipal.Identity.Name;
}
else
{
UserName = "Unauthenticated";
}
}
//Location
public readonly string MachineName;
public readonly string AppDomainName;
public readonly int ThreadID;
public readonly string ThreadName;
public readonly int ContextID;
//Identity
public readonly string UserName;
//Object info
public readonly string AssemblyName;
public readonly string TypeName;
public readonly string MemberAccessed;
public readonly string Date;
public readonly string Time;
//Exception
public readonly string ExceptionName;
public readonly string ExceptionMessage;
//Event
public readonly string Event;
}
|
Example 4 contains most of the implementation of LogSink. The constructor saves the logging filer (methods or errors), as well as the next message sink in the chain, and creates a new Logbook object (a proxy to the remote singleton). In SyncProcessMessage( ), LogSink downcasts the message object to IMethodMessageLogSink then forwards the call to the next sink down the chain, to eventually call the object. When the call returns, LogSink downcasts the returned message to IMethodReturnMessage and uses other helper methods to get the exception information (if an exception took place). When the processing is done, LogSink constructs a LogbookEntry object and adds it to the logbook using the Logbook object. and passes it to a few helper parsing methods.
Example 4. The LogSink class
public class LogSink : IMessageSink
{
IMessageSink m_NextSink;
LogOption m_LogOption;
Logbook m_Logbook;
public LogSink(IMessageSink nextSink,LogOption logOption)
{
m_LogOption = logOption;
m_NextSink = nextSink;
m_Logbook = new Logbook( );
}
public IMessageSink NextSink
{
get {return m_NextSink;}
}
public IMessage SyncProcessMessage(IMessage msg)
{
IMethodMessage methodMessage = msg as IMethodMessage;
Debug.Assert(methodMessage != null);
string assemblyName = GetAssemblyName(methodMessage);
string typeName = GetTypeName(methodMessage);
string methodName = GetMethodName(methodMessage);
IMethodReturnMessage returnedMessage;
returnedMessage = m_NextSink.SyncProcessMessage(msg) as IMethodReturnMessage;
Debug.Assert(returnedMessage != null);
string exceptionName = GetExceptionName(returnedMessage);
string exceptionMessage = GetExceptionMessage(returnedMessage);
LogbookEntry logbookEntry = new LogbookEntry(assemblyName,
typeName,methodName,
exceptionName,exceptionMessage);
DoLogging(logbookEntry);
return returnedMessage;
}
public IMessageCtrl AsyncProcessMessage(IMessage msg,IMessageSink replySink)
{
/* Processing of the message, similar to SyncProcessMessage( ) */
}
void DoLogging(LogbookEntry logbookEntry)
{
if(m_LogOption == LogOption.MethodCalls)
{
LogCall(logbookEntry);
}
if(m_LogOption == LogOption.Errors)
{
if(logbookEntry.ExceptionName != String.Empty)
{
LogCall(logbookEntry);
}
}
}
void LogCall(LogbookEntry logbookEntry)
{
m_Logbook.AddEntry(logbookEntry);
}
static string GetMethodName(IMethodMessage methodMessage)
{
/* Processes methodMessage.MethodName */
}
static string GetTypeName(IMethodMessage methodMessage)
{
/* Processes methodMessage.TypeName */
}
static string GetAssemblyName(IMethodMessage methodMessage)
{
/* Processes methodMessage.TypeName */
}
static string GetExceptionName(IMethodReturnMessage returnedMessage)
{
/* Processes returnedMessage.Exception */
}
static string GetExceptionMessage(IMethodReturnMessage returnedMessage)
{
/* Processes returnedMessage.Exception.Message */
}
}
|
The Logbook component derives from the Component class, defined in the System.ComponentModel namespace. Deriving from Component allows you to use Visual Studio 2005 to generate much of the ADO.NET data connectivity classes and code. However, Logbook must be available for remoting. Fortunately, Component derives from MarshalByRefObject. The Logbook component overrides InitializeLifetimeService( ) and provides a null lease. This is required to maintain the singleton semantics:
public class Logbook : Component
{
//Logbook should be used as a singleton
public override object InitializeLifetimeService( )
{
return null;
}
/* Rest of the implementation */
}
The Logbook component uses ADO.NET to connect to the Logbook database and store or retrieve the entries using a DataSet. Logbook is a thread-safe component that locks itself in every method call to synchronize concurrent access.
Although this
functionality is unrelated to contexts and interception, I thought it
would be handy if any object (even a non-context-bound object using the
service) could explicitly log information to the logbook. This is done
using the static method AddEvent( ) of Logbook:
public class MyClass
{
public void SomeMethod( )
{
Logbook.AddEvent("Some event took place");
}
}
The AddEvent( ) implementation captures the same information as LogSink, and it uses the same LogbookEntry struct. The big difference is that AddEvent( ) doesn't use interception. Instead, it uses the StackFrame class, defined in the System.Diagnostics namespace:
public static void AddEvent(string description)
{
StackFrame frame = new StackFrame(1);//Get the frame of the caller
string typeName = frame.GetMethod().DeclaringType.ToString( );
string methodName = frame.GetMethod( ).Name;
string assemblyName = Assembly.GetCallingAssembly().GetName( ).Name;
LogbookEntry logbookEntry = new LogbookEntry(assemblyName,
typeName,methodName,description);
Logbook logbook = new Logbook( );
logbook.AddEntry(logbookEntry);
}
StackFrame provides access to information on every caller up the call chain. In this case, AddEvent( ) simply extracts the information on the method that called it.
